In [1]:
import json
import math
import time
import copy
import random
import numpy as np
import torch
import torch.nn as nn
import torch.optim as optim
from wsbignn import WSBiGNN
import matplotlib.pyplot as plt
from matplotlib import pyplot as plt
torch.autograd.set_detect_anomaly(True)
Out[1]:
<torch.autograd.anomaly_mode.set_detect_anomaly at 0x7f31144d9040>
In [2]:
#1. set parameters
#2. visualization
#3. compute the loss
#4. initialize user embeddings
#5. compute adjacency matrix based on mobility and web search
#6. train
#7. compute the Recall and NDCG
#8. main
#9. save

1: set parameters¶

In [3]:
print (torch.cuda.is_available())
device = torch.device("cuda:0")
random_seed = 42
random.seed(random_seed)
torch.manual_seed(random_seed)
torch.cuda.manual_seed(random_seed)
r = random.random
True
In [4]:
x_day, y_day = 1, 1  
case = str(x_day) + "_" + str(y_day)
train_ratio, validate_ratio = 0.70, 0.10
top_k, npr = 3, 5
num_epochs, batch_size, learning_rate = 200, 2, 0.001
hid_dim = 32
hid_dim_cons = 32
hyper_param = {"n_e": num_epochs, "b_s": batch_size, "l_r": learning_rate, "top_k": top_k}
In [5]:
root_path = "/home/umni2/a/umnilab/users/xue120/umni4/2023_web_mobility_summer"+\
                "/1_data_check/data_feature_generation/"
file_name = root_path + "feature_" + str(x_day) + "_" + str(y_day)
train_path = file_name + "/train.json"
vali_path = file_name + "/validate.json"
test_path = file_name + "/test.json"
sampled_user_location_path = file_name + "/sampled_user_location.json"
member_path = root_path + "member/"

2: visualization¶

In [6]:
def visual_train_loss(e_losses):
    plt.figure(figsize=(4,3), dpi=300)
    x = range(len(e_losses))
    y1 = copy.copy(e_losses)
    plt.plot(x,y1, linewidth=1,  label="train")
    plt.legend()
    plt.title('Loss decline on training data')
    plt.xlabel('Epoch')
    plt.ylabel('Loss')
    plt.savefig(case + '/' + 'train_loss.png',bbox_inches = 'tight')
    plt.show()
    
def visual_vali_test_loss(recall_vali, recall_test, ndcg_vali, ndcg_test):
    plt.figure(figsize=(4,3), dpi=300)
    x = range(len(recall_vali))    
    plt.plot(x, recall_vali, linewidth=1, label="Recall_validate")
    plt.plot(x, ndcg_vali, linewidth=1, label="NDCG_validate")
    plt.plot(x, recall_test, linewidth=1, label="Recall_test")
    plt.plot(x, ndcg_test, linewidth=1, label="NDCG_test")
    plt.legend()
    plt.title('Recall/NDCG on validate/test sets')
    plt.xlabel('Epoch')
    plt.ylabel('Recall@3, NDCG@3')
    plt.savefig(case + '/' + 'vali_test_recall_ndcg.png',bbox_inches = 'tight')
    plt.show()

3: compute the loss¶

In [7]:
#compute the cross entropy loss
#input1:  gnn_output   dim = (batch, y_day, U, V).
#input2:  real_link    dim = (batch, y_day, n_edge, 2).
#input3:  criterion
#inputs 4,5,6:  n_user, n_loc, npr
#output: average loss for batch*y_day terms
def compute_loss(gnn_output, real_link, criterion, n_user, n_loc, npr):
    batch, y_day = gnn_output.size()[0], gnn_output.size()[1]
    loss = torch.tensor([0.0])
    all_edge = [str(u)+"_"+str(v) for u in range(n_user) for v in range(n_loc)]
    
    for i in range(batch):
        for j in range(y_day):
            predicted, real = gnn_output[i][j], real_link[i][j] 
            #positive edges
            str_real = [str(int(real[k][0])) + "_" + str(int(real[k][1])) for k in range(len(real))]
            num_real = len(real) - str_real.count(str(-1)+"_"+str(-1))
            set_pos = set(str_real[0: num_real])
            all_pos = list(set_pos)
            n_pos = len(all_pos)
            
            #sample negative edges
            all_neg = list(set(all_edge) - set_pos)
            n_sampled_neg = int(n_pos * npr)
            sampled_neg = random.sample(all_neg, n_sampled_neg)
            
            #prepare for loss computing
            pos = [[int(item.split("_")[0]), int(item.split("_")[1])] for item in all_pos] 
            neg = [[int(item.split("_")[0]), int(item.split("_")[1])] for item in sampled_neg] 
            pos_idx = [pos[k][0]*n_loc + pos[k][1] for k in range(n_pos)]
            neg_idx = [neg[k][0]*n_loc + neg[k][1] for k in range(n_sampled_neg)]
            hat_1_pos = torch.take(predicted, torch.tensor(pos_idx)) 
            hat_1_neg = torch.take(predicted, torch.tensor(neg_idx))
            hat_1 = torch.sigmoid(torch.cat((hat_1_pos, hat_1_neg)).unsqueeze(dim=0))  
            hat = torch.log(torch.transpose(torch.cat((1.0-hat_1, hat_1), dim=0),1,0))  #NLLLOSS
            
            real = torch.tensor([1]*n_pos + [0]*n_sampled_neg)
            loss += criterion(hat, real)
    loss = loss*1.0/(batch*y_day)
    return loss

4: initialize user embeddings¶

In [8]:
#define user embeddings based on POI embeddings.
#input1: x_loc             dim = (V, 200)
#input2: x_mob_batch      dim = (batch, x_day, n_m, 2)
#input3: x_text_batch         dim = (batch, x_day, n_t, 2)
#input4: n_user         
#output: x_user                dim = (batch, U, 200)
def compute_user_embedding(x_loc, x_mob_batch, x_text_batch, n_user):
    x_user = torch.zeros((0, n_user, 200), device=device)
    x_m_t_batch = torch.cat([x_mob_batch, x_text_batch], dim=2)  #dim = (batch, x_day, n_m+n_t, 2)
    batch = x_m_t_batch.size()[0]
    
    for i in range(batch):
        #initialize 
        user_sum_embed = torch.zeros((n_user, 200), device=device)
        user_ave_embed = torch.zeros((n_user, 200), device=device)
        user_count_embed, user_with_edge = [0]*n_user, list()

        #update user embeddings
        link_record = x_m_t_batch[i][0]  #extract the first day
        for link in link_record:
            if link[0] != -1:
                user, loc = link[0], link[1] 
                user_with_edge.append(user)              
                user_count_embed[user] = user_count_embed[user] + 1     
                user_sum_embed[user] = user_sum_embed[user] + x_loc[loc]
            else:
                break
                
        set_user_with_edge = set(user_with_edge)
        for user in set_user_with_edge:
            user_ave_embed[user] = user_sum_embed[user]/user_count_embed[user]
        
        #update the user embedding for other users with mobility records on the first day
        #compute the average embedding  
        n_user_with_edge = len(set_user_with_edge)
        ave_embedding = torch.sum(user_ave_embed, dim=0)/(1.0*n_user_with_edge)
        
        #define the embeddings for remaining users as the average embedding 
        set_remain = set(range(n_user))-set_user_with_edge
        dict_remain = {user:0 for user in set_remain}
        for user in dict_remain:
            user_ave_embed[user] = ave_embedding
        
        #concatenate different batches
        x_user = torch.cat([x_user, user_ave_embed.unsqueeze(0)],dim=0)
    return x_user                                        

5: compute adjacency matrix based on mobility and web search¶

In [9]:
#input1: x_mob_batch       dim = (batch, x_day, n_m, 2)
#input2: x_text_batch      dim = (batch, x_day, n_t, 2)
#inputs3,4: u_user, n_loc
#output1: x_adj            dim = (batch, x_day, n_user+2*n_loc, n_user+2*n_loc)
def convert_to_adj(x_mob_batch, x_text_batch, n_user, n_loc):
    time_1 = time.time()
    batch, x_day = x_mob_batch.size()[0], x_mob_batch.size()[1]
    adj_dim = n_user + 2*n_loc
    adj = torch.zeros((batch, x_day, adj_dim, adj_dim), device=device)
    
    for i in range(batch):
        x_mob_record, x_text_record = x_mob_batch[i], x_text_batch[i]
        for j in range(x_day):
            x_mob_one_day, x_text_one_day = x_mob_record[j], x_text_record[j]
            #extract mob edges
            for link in x_mob_one_day:
                if link[0] != -1:
                    user, loc = link[0], link[1]
                    n_idx = n_user + loc
                    adj[i][j][user][n_idx] = adj[i][j][user][n_idx] + 1 
                    adj[i][j][n_idx][user] = adj[i][j][user][n_idx]
                else:
                    break
            
            #extract text edges
            for link in x_text_one_day:
                if link[0] != -1:
                    user, loc = link[0], link[1] 
                    n_idx = n_user + n_loc + loc
                    adj[i][j][user][n_idx] = adj[i][j][user][n_idx] + 1
                    adj[i][j][n_idx][user] = adj[i][j][user][n_idx]
                else:
                    break
    return adj

6: train¶

In [10]:
#6.1: one training epoch   
#output: the average loss, model         
def train_epoch(model, opt, criterion, train, hyper_param_dict, y_day, npr, loss_batch_all):
    time_1 = time.time()
    model.train()
    losses = list()
    
    n_user, n_loc, b_s = hyper_param["n_user"], hyper_param["n_loc"], hyper_param["b_s"]
    x_u_v, x_poi, train_x_mob, train_x_text, train_y_mob =\
        train["u_v"].to(device), train["x_poi"].to(device), train["x_mob"],\
            train["x_text"], train["y_mob"]
    n = train_x_mob.size()[0] 
    print ("# batch: ", int(n/b_s))
    
    for i in range(0, n-b_s, b_s):
        time_1 = time.time()          
        x_mob_batch, x_text_batch, y_mob_batch = train_x_mob[i:i + b_s], train_x_text[i:i + b_s], train_y_mob[i:i + b_s]    
    
        opt.zero_grad()
        
        loss = torch.zeros(1, dtype=torch.float)
        x_user = compute_user_embedding(x_poi, x_mob_batch, x_text_batch, n_user)  #4.
        
        x_adj = convert_to_adj(x_mob_batch, x_text_batch, n_user, n_loc)                  #5. 
        
        model_output = model.run(x_u_v, x_poi, x_user.to(device), x_adj.to(device), b_s) 
        
        loss = compute_loss(model_output.cpu(), y_mob_batch, criterion, n_user, n_loc, npr)  #3.
        loss_batch_all.append(loss.data.numpy()[0])
        loss.backward()
        opt.step()
        losses.append(loss.data.numpy())  # sum over batches
        
        time2 = time.time()
        if i%20 == 0:
            print ("i_batch: ", i/b_s)
            print ("the loss is: ", loss.data.numpy()[0])
            print ("time for this batch: ", round(time2 - time_1,3))
            print ("-----------------a batch ends---------------")
    return sum(losses)/float(len(losses)+0.000001), model, loss_batch_all
In [11]:
#6.2
def train_process(train, vali, test, net, criterion, hyper_param, y_day, loss_batch_all):   
    e_losses_train = list()
    recall_vali, recall_test, ndcg_vali, ndcg_test = list(), list(), list(), list()
    l_r, n_e, b_s  = hyper_param["l_r"], hyper_param["n_e"], hyper_param["b_s"]

    opt = optim.Adam(net.parameters(), l_r, betas = (0.9,0.999), weight_decay = 0.0001)
    opt_scheduler = torch.optim.lr_scheduler.MultiStepLR(opt, milestones=[150]) 
    print ("# epochs: ", n_e)
    print ("------------------------------------------------------------")        
    time_start = time.time()
    no_improve_in_n = 0
    
    #prepare for vali and test
    print ("start preparing for vali and test")
    vali_u_v, vali_x_poi, vali_x_user, vali_x_adj, vali_y_real = prepare_validate_test(vali, hyper_param)
    print ("finish vali")
    test_u_v, test_x_poi, test_x_user, test_x_adj, test_y_real = prepare_validate_test(test, hyper_param)
    print ("finish test")
           
    for i in range(n_e):
        print ("i_epoch: ", i)
        print ("----------------an epoch starts-------------------")
        time1 = time.time()
        n_train = len(train["x_mob"])
        number_list = copy.copy(list(range(n_train)))
        random.shuffle(number_list, random = r)
        shuffle_idx = torch.tensor(number_list)
        
        #train one epoch
        train_shuffle = dict()
        train_shuffle["u_v"] = train["u_v"]
        train_shuffle["x_poi"], train_shuffle["x_mob"] = train["x_poi"], train["x_mob"][shuffle_idx]
        train_shuffle["x_text"], train_shuffle["y_mob"] = train["x_text"][shuffle_idx], train["y_mob"][shuffle_idx]
        
        loss, net, loss_batch_all =  train_epoch(net, opt, criterion, train_shuffle, hyper_param, y_day, npr, loss_batch_all)
        
        opt_scheduler.step() 
        
        loss = float(loss)
        print ("train loss for this epoch: ", round(loss, 6))
        e_losses_train.append(loss)
        visual_train_loss(e_losses_train)
        
        print ("----------------validate-------------------")
        val_all_recall, val_all_ndcg, val_ave_recall, val_ave_ndcg =\
                validate_test(net, hyper_param, \
                              vali_u_v, vali_x_poi, vali_x_user, vali_x_adj, vali_y_real, False)
        
        print ("----------------test-------------------")
        test_all_recall, test_all_ndcg, test_ave_recall, test_ave_ndcg =\
               validate_test(net, hyper_param,\
                             test_u_v, test_x_poi, test_x_user, test_x_adj, test_y_real, False)
        
        if len(recall_vali) > 0:
            past_max = np.max(recall_vali)
        else:
            past_max = 0.0
        recall_vali.append(val_ave_recall)
        recall_test.append(test_ave_recall)
        ndcg_vali.append(val_ave_ndcg)
        ndcg_test.append(test_ave_ndcg)
        visual_vali_test_loss(recall_vali, recall_test, ndcg_vali, ndcg_test)
        
        #store
        performance = {"recall_val": recall_vali, "recall_test": recall_test, \
                       "ndcg_val": ndcg_vali,"ndcg_test": ndcg_test,\
                        "e_losses_train": e_losses_train}
        subfile =  open(case + '/' + 'performance'+'.json','w')
        json.dump(performance, subfile)
        subfile.close()
                    
        #early stop
        if val_ave_recall < past_max:
            no_improve_in_n = no_improve_in_n + 1
        else:
            no_improve_in_n = 0
        if no_improve_in_n == 30:
            print ("Early stop at the " + str(i+1) + "-th epoch")
            return e_losses_train, net, loss_batch_all
        time2 = time.time()
        print ("running time for this epoch: ", time2 - time1)
        time_now = time.time()
        print ("running time until now: ", time_now - time_start)
        print ("-------------------------an epoch ends ---------------------------")
    return e_losses_train, net, loss_batch_all
In [12]:
#6.3
def model_train(train, vali, test, hyper_param, x_day, y_day, member):
    with torch.autograd.set_detect_anomaly(True):       
        loss_batch_all = list()
        model = WSBiGNN(hid_dim, hid_dim_cons, x_day, member).to(device)          
        criterion = nn.NLLLoss() 
        print ("start train_process")
        e_losses, trained_model, loss_batch_all = train_process(train, vali, test, model,\
                                                criterion, hyper_param, y_day, loss_batch_all)  
        return e_losses, trained_model, loss_batch_all

7: compute the Recall and NDCG¶

In [13]:
#7.1: compute Recall@K, NDCG@K
#input1:  gnn_output   dim = (batch, y_day, U, V)
#input2:  real_link    dim = (batch, y_day, n_edge, 2)
#inputs3,4:  n_user, n_loc
#input5: top_k
#output: Recall@K, NDCG@K
def compute_recall_ndcg(gnn_output, real_link, n_user, n_loc, top_k):
    batch, y_day = gnn_output.size()[0], gnn_output.size()[1]
    recall_all = [[0.0 for j in range(y_day)] for i in range(batch)] 
    ndcg_all = [[0.0 for j in range(y_day)] for i in range(batch)] 
    
    for i in range(batch):
        for j in range(y_day):
            recall_user, ndcg_user = {}, {}
            predicted, real = gnn_output[i][j].tolist(), real_link[i][j] 
            
            #1. construct the real mobility
            real_list, real_dict = {user: [] for user in range(n_user)}, {user: {} for user in range(n_user)}
            for k in range(len(real)):
                edge = real[k]
                user, poi = int(edge[0]), int(edge[1])
                if user > -1:
                    real_list[user].append(poi)
                else:
                    break
            for user in real_list:
                real_dict[user] = set(real_list[user])
            
            #2. compute Recall@K, NDCG@K
            for user in real_dict:
                real_poi = real_dict[user]
                len_real_poi = len(real_poi)
                if len_real_poi > 0:
                    predict_row = predicted[user]                 #[0,0,12,1,5]
                    largest_k_idx = np.argsort(predict_row)[::-1] #[2,4,3,1,0]
                    top_k_idx = largest_k_idx[0: top_k]            #[2,4,3]
                    
                    #compute Recall
                    predict_top_k = set(top_k_idx)
                    recall_user[user] = len(predict_top_k.intersection(real_poi))*1.0/len_real_poi
                    
                    #compute NDCG
                    weight = [1.0/(math.log(k+2)/math.log(2.0)) for k in range(top_k)]
                    #denominator
                    if len_real_poi < top_k:
                         best_rank = [1.0]*len_real_poi + [0.0]*(top_k-len_real_poi)
                    else:
                         best_rank = [1.0]*top_k        
                    #numerator  
                    predict_rank = [0.0]* top_k
                    for idx in range(len(top_k_idx)):
                        if top_k_idx[idx] in real_poi:
                            predict_rank[idx] = 1.0
                    #NDCG
                    ndcg_user[user] = float(np.dot(weight, predict_rank)/np.dot(weight, best_rank))
            
            #3. compute the average Recall@k, average NDCG@k.
            recall_all[i][j] = float(np.mean(list(recall_user.values())))
            ndcg_all[i][j] = float(np.mean(list(ndcg_user.values())))
    ave_recall, ave_ndcg = np.mean(recall_all), np.mean(ndcg_all)
    print ("ave Recall", ave_recall)
    print ("ave NDCG", ave_ndcg)
    return recall_all, ndcg_all, ave_recall, ave_ndcg

#7.2: evaluate the trained model on validation or test 
def prepare_validate_test(vali_test, hyper_param):
    n_user, n_loc = hyper_param["n_user"], hyper_param["n_loc"]
    u_v, x_poi, x_mob, x_text, y_real =\
        vali_test["u_v"].to(device), vali_test["x_poi"].to(device), vali_test["x_mob"].to(device), \
            vali_test["x_text"].to(device), vali_test["y_mob"]
    x_user = compute_user_embedding(x_poi, x_mob, x_text, n_user)
    x_adj = convert_to_adj(x_mob, x_text, n_user, n_loc)
    return u_v, x_poi, x_user, x_adj, y_real

def validate_test(trained_model, hyper_param, u_v, x_poi, x_user, x_adj, y_real, output=False):  
    n_user, n_loc = hyper_param["n_user"], hyper_param["n_loc"]
    top_k, b_s = hyper_param["top_k"], y_real.size()[0]
    
    y_hat = trained_model.run(u_v, x_poi, x_user, x_adj, b_s)
    all_recall, all_ndcg, ave_recall, ave_ndcg =\
        compute_recall_ndcg(y_hat.cpu(), y_real, n_user, n_loc, top_k)
    
    if output == True:
        return all_recall, all_ndcg, ave_recall, ave_ndcg, y_hat.cpu(), y_real
    else:
        return all_recall, all_ndcg, ave_recall, ave_ndcg

8: train¶

In [14]:
#8.1: tensorize
def tensorize(train_vali_test):
    result = dict()
    result["u_v"] = torch.tensor(train_vali_test["u_v"]) 
    result["x_poi"] = torch.tensor(train_vali_test["x_poi"])     
    result["x_mob"] = torch.tensor(train_vali_test["x_mob"]) 
    result["x_text"] = torch.tensor(train_vali_test["x_text"]) 
    result["y_mob"] = torch.tensor(train_vali_test["y_mob"]) 
    return result
In [15]:
#8.2: load the data
train = tensorize(json.load(open(train_path)))
vali = tensorize(json.load(open(vali_path)))
test = tensorize(json.load(open(test_path)))
sampled_user_location = json.load(open(sampled_user_location_path))
sampled_user_location["n_user"] = len(sampled_user_location["u"])
sampled_user_location["n_loc"] = len(sampled_user_location["p"])

u_list, p_list = sampled_user_location["u"], sampled_user_location["p"]
hyper_param["n_user"], hyper_param["n_loc"] = len(u_list), len(p_list)

#supernode
member_dict = json.load(open(member_path + "member_" + case + ".json"))
#sg, s_ng, ns_g, ns_ng
member = torch.tensor([member_dict["s_g"], member_dict["s_ng"],\
                       member_dict["ns_g"], member_dict["ns_ng"]], device=device)
In [16]:
#8.3: model 
e_losses, trained_model, loss_batch_all = model_train(train, vali, test, hyper_param,\
                                                      x_day, y_day, member)
start train_process
# epochs:  200
------------------------------------------------------------
start preparing for vali and test
finish vali
finish test
i_epoch:  0
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  6.3969564
time for this batch:  1.123
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  1.8045813
time for this batch:  0.508
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.88257504
time for this batch:  0.463
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.7343185
time for this batch:  0.484
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.70127106
time for this batch:  0.454
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.68681365
time for this batch:  0.554
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.67532927
time for this batch:  0.511
-----------------a batch ends---------------
train loss for this epoch:  1.303906
----------------validate-------------------
ave Recall 0.06875578168892488
ave NDCG 0.05025670364715043
----------------test-------------------
ave Recall 0.07180526424109365
ave NDCG 0.053380978988274076
running time for this epoch:  34.62391805648804
running time until now:  78.84622812271118
-------------------------an epoch ends ---------------------------
i_epoch:  1
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.6730496
time for this batch:  0.504
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.66028297
time for this batch:  0.521
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.647086
time for this batch:  0.491
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.6300049
time for this batch:  0.543
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.6106366
time for this batch:  0.499
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.58880067
time for this batch:  0.53
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.56676275
time for this batch:  0.423
-----------------a batch ends---------------
train loss for this epoch:  0.624365
----------------validate-------------------
ave Recall 0.04423010690388035
ave NDCG 0.029136390092705182
----------------test-------------------
ave Recall 0.04560144415153154
ave NDCG 0.03135798146968434
running time for this epoch:  34.17757201194763
running time until now:  113.02385449409485
-------------------------an epoch ends ---------------------------
i_epoch:  2
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.55525213
time for this batch:  0.446
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.5270248
time for this batch:  0.478
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.49517807
time for this batch:  0.507
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.45796117
time for this batch:  0.354
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.4307739
time for this batch:  0.431
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.4049234
time for this batch:  0.496
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.3896345
time for this batch:  0.5
-----------------a batch ends---------------
train loss for this epoch:  0.463244
----------------validate-------------------
ave Recall 0.2647306266166659
ave NDCG 0.24635881086945155
----------------test-------------------
ave Recall 0.2242032600452053
ave NDCG 0.2084741635063872
running time for this epoch:  32.41323280334473
running time until now:  145.43714356422424
-------------------------an epoch ends ---------------------------
i_epoch:  3
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.3777105
time for this batch:  0.461
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.36459208
time for this batch:  0.457
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.34078342
time for this batch:  0.531
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.31972024
time for this batch:  0.482
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.32073146
time for this batch:  0.504
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.3137117
time for this batch:  0.5
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.2724778
time for this batch:  0.543
-----------------a batch ends---------------
train loss for this epoch:  0.322817
----------------validate-------------------
ave Recall 0.5171020000415515
ave NDCG 0.4410306410622091
----------------test-------------------
ave Recall 0.4777388893498675
ave NDCG 0.40240117760885674
running time for this epoch:  34.61087918281555
running time until now:  180.04807591438293
-------------------------an epoch ends ---------------------------
i_epoch:  4
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.283382
time for this batch:  0.43
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.23820877
time for this batch:  0.637
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.23409215
time for this batch:  0.432
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.23337656
time for this batch:  0.444
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.24091065
time for this batch:  0.539
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.2362583
time for this batch:  0.434
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.24233794
time for this batch:  0.501
-----------------a batch ends---------------
train loss for this epoch:  0.246297
----------------validate-------------------
ave Recall 0.6017037674865294
ave NDCG 0.5159714453509998
----------------test-------------------
ave Recall 0.5765639939689624
ave NDCG 0.48659769140963005
running time for this epoch:  33.48040199279785
running time until now:  213.52853274345398
-------------------------an epoch ends ---------------------------
i_epoch:  5
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.24427664
time for this batch:  0.42
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.20822614
time for this batch:  0.486
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.21266416
time for this batch:  0.528
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.1993443
time for this batch:  0.547
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.20975807
time for this batch:  0.526
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.21426582
time for this batch:  0.471
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.18476146
time for this batch:  0.478
-----------------a batch ends---------------
train loss for this epoch:  0.212646
----------------validate-------------------
ave Recall 0.637492203846818
ave NDCG 0.5435913954778022
----------------test-------------------
ave Recall 0.6119902956395035
ave NDCG 0.5169124173826688
running time for this epoch:  34.3148455619812
running time until now:  247.843430519104
-------------------------an epoch ends ---------------------------
i_epoch:  6
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.18869302
time for this batch:  0.4
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.19234173
time for this batch:  0.522
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.228041
time for this batch:  0.557
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.18585122
time for this batch:  0.493
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.21195674
time for this batch:  0.439
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.20989296
time for this batch:  0.443
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.23007865
time for this batch:  0.422
-----------------a batch ends---------------
train loss for this epoch:  0.195338
----------------validate-------------------
ave Recall 0.6501840285562419
ave NDCG 0.5550104889805474
----------------test-------------------
ave Recall 0.6287310097904519
ave NDCG 0.5314420805858153
running time for this epoch:  33.00169920921326
running time until now:  280.845187664032
-------------------------an epoch ends ---------------------------
i_epoch:  7
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.19936459
time for this batch:  0.4
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.18679032
time for this batch:  0.461
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.19657025
time for this batch:  0.524
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.17340615
time for this batch:  0.476
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.19898328
time for this batch:  0.483
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.2017974
time for this batch:  0.504
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.21720883
time for this batch:  0.531
-----------------a batch ends---------------
train loss for this epoch:  0.184516
----------------validate-------------------
ave Recall 0.661319163847969
ave NDCG 0.5618723976507842
----------------test-------------------
ave Recall 0.641443690641535
ave NDCG 0.5402686771746305
running time for this epoch:  33.37122368812561
running time until now:  314.2164590358734
-------------------------an epoch ends ---------------------------
i_epoch:  8
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.17683703
time for this batch:  0.408
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.16381937
time for this batch:  0.444
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.17411396
time for this batch:  0.431
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.17340052
time for this batch:  0.482
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.1877551
time for this batch:  0.542
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.16434854
time for this batch:  0.496
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.18911085
time for this batch:  0.525
-----------------a batch ends---------------
train loss for this epoch:  0.175745
----------------validate-------------------
ave Recall 0.6648409526804692
ave NDCG 0.5672378861821313
----------------test-------------------
ave Recall 0.6472441838394826
ave NDCG 0.5452541001965666
running time for this epoch:  33.417980432510376
running time until now:  347.6344804763794
-------------------------an epoch ends ---------------------------
i_epoch:  9
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.16148594
time for this batch:  0.527
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.1589759
time for this batch:  0.498
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.16271439
time for this batch:  0.533
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.15194346
time for this batch:  0.534
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.18144463
time for this batch:  0.462
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.19551769
time for this batch:  0.482
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15918063
time for this batch:  0.458
-----------------a batch ends---------------
train loss for this epoch:  0.170654
----------------validate-------------------
ave Recall 0.663970888433568
ave NDCG 0.5630096348709781
----------------test-------------------
ave Recall 0.6512667163957527
ave NDCG 0.5466391621778552
running time for this epoch:  33.627700328826904
running time until now:  381.26222133636475
-------------------------an epoch ends ---------------------------
i_epoch:  10
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.15823698
time for this batch:  0.457
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.17721486
time for this batch:  0.492
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.16376337
time for this batch:  0.499
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.16107461
time for this batch:  0.51
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.17335552
time for this batch:  0.538
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.17541406
time for this batch:  0.589
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.16310167
time for this batch:  0.545
-----------------a batch ends---------------
train loss for this epoch:  0.16815
----------------validate-------------------
ave Recall 0.6663587352094644
ave NDCG 0.5685488726585942
----------------test-------------------
ave Recall 0.650335267560882
ave NDCG 0.5446942056775644
running time for this epoch:  34.406033515930176
running time until now:  415.6682999134064
-------------------------an epoch ends ---------------------------
i_epoch:  11
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.16300258
time for this batch:  0.434
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14996485
time for this batch:  0.475
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13827229
time for this batch:  0.491
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14448571
time for this batch:  0.585
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.16297753
time for this batch:  0.401
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.18566021
time for this batch:  0.511
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.18819153
time for this batch:  0.537
-----------------a batch ends---------------
train loss for this epoch:  0.161758
----------------validate-------------------
ave Recall 0.6687495548255238
ave NDCG 0.5713286835039624
----------------test-------------------
ave Recall 0.6516468703957582
ave NDCG 0.5495792858997594
running time for this epoch:  34.70919990539551
running time until now:  450.37753987312317
-------------------------an epoch ends ---------------------------
i_epoch:  12
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.15359835
time for this batch:  0.516
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14470345
time for this batch:  0.484
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.17447552
time for this batch:  0.565
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.16455373
time for this batch:  0.563
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.15332055
time for this batch:  0.476
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.1564025
time for this batch:  0.461
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14238136
time for this batch:  0.546
-----------------a batch ends---------------
train loss for this epoch:  0.159697
----------------validate-------------------
ave Recall 0.6675868385913529
ave NDCG 0.5671178692462775
----------------test-------------------
ave Recall 0.6581297461747129
ave NDCG 0.5485526158097943
running time for this epoch:  34.80811429023743
running time until now:  485.1857056617737
-------------------------an epoch ends ---------------------------
i_epoch:  13
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.16747913
time for this batch:  0.396
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14866476
time for this batch:  0.518
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.16044196
time for this batch:  0.443
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14729086
time for this batch:  0.396
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.15614723
time for this batch:  0.458
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.1683563
time for this batch:  0.512
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.1566706
time for this batch:  0.676
-----------------a batch ends---------------
train loss for this epoch:  0.157662
----------------validate-------------------
ave Recall 0.6706226665530768
ave NDCG 0.5667679218751731
----------------test-------------------
ave Recall 0.6529629397226818
ave NDCG 0.5473962076809579
running time for this epoch:  32.26416730880737
running time until now:  517.4499268531799
-------------------------an epoch ends ---------------------------
i_epoch:  14
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13867661
time for this batch:  0.437
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.1695499
time for this batch:  0.435
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.15043442
time for this batch:  0.44
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.15100662
time for this batch:  0.544
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.18613297
time for this batch:  0.524
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.15749225
time for this batch:  0.511
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15949386
time for this batch:  0.42
-----------------a batch ends---------------
train loss for this epoch:  0.154689
----------------validate-------------------
ave Recall 0.6734722325755799
ave NDCG 0.5704524183748583
----------------test-------------------
ave Recall 0.6548260187389746
ave NDCG 0.5519900122453228
running time for this epoch:  34.13838219642639
running time until now:  551.5883512496948
-------------------------an epoch ends ---------------------------
i_epoch:  15
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.15633827
time for this batch:  0.461
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.16152447
time for this batch:  0.491
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.15440176
time for this batch:  0.511
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.15702155
time for this batch:  0.539
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14823872
time for this batch:  0.488
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.15315014
time for this batch:  0.481
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14798266
time for this batch:  0.504
-----------------a batch ends---------------
train loss for this epoch:  0.153431
----------------validate-------------------
ave Recall 0.6686792558399617
ave NDCG 0.5687315852037589
----------------test-------------------
ave Recall 0.6533410440595192
ave NDCG 0.5509576444774222
running time for this epoch:  34.84659671783447
running time until now:  586.4349927902222
-------------------------an epoch ends ---------------------------
i_epoch:  16
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13768852
time for this batch:  0.378
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.1421906
time for this batch:  0.451
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13665478
time for this batch:  0.423
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.15746006
time for this batch:  0.482
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.15059254
time for this batch:  0.528
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14817584
time for this batch:  0.493
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15361483
time for this batch:  0.48
-----------------a batch ends---------------
train loss for this epoch:  0.152741
----------------validate-------------------
ave Recall 0.6705057212258863
ave NDCG 0.5708026742653125
----------------test-------------------
ave Recall 0.6582057882365497
ave NDCG 0.5531622796493137
running time for this epoch:  34.01503229141235
running time until now:  620.450070142746
-------------------------an epoch ends ---------------------------
i_epoch:  17
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.15892923
time for this batch:  0.421
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.1711742
time for this batch:  0.459
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13786128
time for this batch:  0.536
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.16026616
time for this batch:  0.465
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13721569
time for this batch:  0.563
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13851586
time for this batch:  0.479
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15262434
time for this batch:  0.504
-----------------a batch ends---------------
train loss for this epoch:  0.150514
----------------validate-------------------
ave Recall 0.6703868894318319
ave NDCG 0.5708946457041358
----------------test-------------------
ave Recall 0.6575194034897017
ave NDCG 0.5499370457219254
running time for this epoch:  33.538111209869385
running time until now:  653.988228559494
-------------------------an epoch ends ---------------------------
i_epoch:  18
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14401093
time for this batch:  0.472
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13504615
time for this batch:  0.34
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.15258715
time for this batch:  0.659
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.143073
time for this batch:  0.552
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.15275119
time for this batch:  0.514
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.16465385
time for this batch:  0.444
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15455376
time for this batch:  0.365
-----------------a batch ends---------------
train loss for this epoch:  0.149021
----------------validate-------------------
ave Recall 0.6670591047593857
ave NDCG 0.5647555898067868
----------------test-------------------
ave Recall 0.6546107384709834
ave NDCG 0.5508158934900049
running time for this epoch:  33.76143789291382
running time until now:  687.749715089798
-------------------------an epoch ends ---------------------------
i_epoch:  19
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12757903
time for this batch:  0.387
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14827736
time for this batch:  0.435
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13558751
time for this batch:  0.497
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.15731052
time for this batch:  0.579
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14741859
time for this batch:  0.463
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.1511929
time for this batch:  0.429
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.1526005
time for this batch:  0.431
-----------------a batch ends---------------
train loss for this epoch:  0.147029
----------------validate-------------------
ave Recall 0.660998420229153
ave NDCG 0.5600824321291382
----------------test-------------------
ave Recall 0.6532623441635742
ave NDCG 0.545036731341142
running time for this epoch:  33.66139578819275
running time until now:  721.4111547470093
-------------------------an epoch ends ---------------------------
i_epoch:  20
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.16098537
time for this batch:  0.366
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14438275
time for this batch:  0.51
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.1387604
time for this batch:  0.453
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.16506186
time for this batch:  0.44
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.15266752
time for this batch:  0.465
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.140686
time for this batch:  0.54
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14765987
time for this batch:  0.411
-----------------a batch ends---------------
train loss for this epoch:  0.147735
----------------validate-------------------
ave Recall 0.6713639529199167
ave NDCG 0.5670760525781878
----------------test-------------------
ave Recall 0.6562267876921227
ave NDCG 0.5467570171315569
running time for this epoch:  33.547157287597656
running time until now:  754.9583520889282
-------------------------an epoch ends ---------------------------
i_epoch:  21
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14473233
time for this batch:  0.503
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.1436102
time for this batch:  0.483
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14441055
time for this batch:  0.503
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13429944
time for this batch:  0.411
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13352601
time for this batch:  0.405
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.15771651
time for this batch:  0.489
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14809543
time for this batch:  0.483
-----------------a batch ends---------------
train loss for this epoch:  0.145172
----------------validate-------------------
ave Recall 0.6738688599422828
ave NDCG 0.5663077835220581
----------------test-------------------
ave Recall 0.6587652991925672
ave NDCG 0.5512099597310843
running time for this epoch:  33.366509675979614
running time until now:  788.3249032497406
-------------------------an epoch ends ---------------------------
i_epoch:  22
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.1409601
time for this batch:  0.366
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14257641
time for this batch:  0.423
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13882047
time for this batch:  0.438
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.16064516
time for this batch:  0.48
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14317799
time for this batch:  0.554
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.15521228
time for this batch:  0.649
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15195228
time for this batch:  0.487
-----------------a batch ends---------------
train loss for this epoch:  0.146109
----------------validate-------------------
ave Recall 0.6733657562763776
ave NDCG 0.5677453257559637
----------------test-------------------
ave Recall 0.6504426004522873
ave NDCG 0.5497902309939695
running time for this epoch:  32.33656716346741
running time until now:  820.6615147590637
-------------------------an epoch ends ---------------------------
i_epoch:  23
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.1309959
time for this batch:  0.462
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13119438
time for this batch:  0.498
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13806903
time for this batch:  0.454
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13911688
time for this batch:  0.538
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.149346
time for this batch:  0.433
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14148611
time for this batch:  0.501
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14774527
time for this batch:  0.492
-----------------a batch ends---------------
train loss for this epoch:  0.144605
----------------validate-------------------
ave Recall 0.6743454076825763
ave NDCG 0.5725912262130892
----------------test-------------------
ave Recall 0.6547904841746148
ave NDCG 0.5503579963564447
running time for this epoch:  33.085651874542236
running time until now:  853.7472276687622
-------------------------an epoch ends ---------------------------
i_epoch:  24
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14293474
time for this batch:  0.39
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13871038
time for this batch:  0.474
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14215395
time for this batch:  0.531
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.1335378
time for this batch:  0.455
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.1585069
time for this batch:  0.456
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14433235
time for this batch:  0.396
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14058945
time for this batch:  0.472
-----------------a batch ends---------------
train loss for this epoch:  0.14449
----------------validate-------------------
ave Recall 0.6740117349151029
ave NDCG 0.5730612860937011
----------------test-------------------
ave Recall 0.6555936210553917
ave NDCG 0.5509610464630498
running time for this epoch:  33.944616079330444
running time until now:  887.6919076442719
-------------------------an epoch ends ---------------------------
i_epoch:  25
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13280897
time for this batch:  0.38
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13850942
time for this batch:  0.452
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.1420439
time for this batch:  0.408
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14515978
time for this batch:  0.512
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14810279
time for this batch:  0.485
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.1474203
time for this batch:  0.44
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15045106
time for this batch:  0.375
-----------------a batch ends---------------
train loss for this epoch:  0.144352
----------------validate-------------------
ave Recall 0.6742752204484135
ave NDCG 0.5710739126645493
----------------test-------------------
ave Recall 0.6510728402673857
ave NDCG 0.5460817924027812
running time for this epoch:  31.880313396453857
running time until now:  919.5722634792328
-------------------------an epoch ends ---------------------------
i_epoch:  26
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14341542
time for this batch:  0.41
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13513121
time for this batch:  0.374
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.1470652
time for this batch:  0.54
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.1362211
time for this batch:  0.556
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.151658
time for this batch:  0.481
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13350137
time for this batch:  0.483
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14626351
time for this batch:  0.465
-----------------a batch ends---------------
train loss for this epoch:  0.141163
----------------validate-------------------
ave Recall 0.6785999851129796
ave NDCG 0.5748318863389024
----------------test-------------------
ave Recall 0.66028263742526
ave NDCG 0.5541710199044534
running time for this epoch:  32.908998250961304
running time until now:  952.4813048839569
-------------------------an epoch ends ---------------------------
i_epoch:  27
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.16364196
time for this batch:  0.397
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.12749581
time for this batch:  0.389
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13914028
time for this batch:  0.473
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.1427724
time for this batch:  0.508
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14993717
time for this batch:  0.486
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13672951
time for this batch:  0.402
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.1450214
time for this batch:  0.536
-----------------a batch ends---------------
train loss for this epoch:  0.141314
----------------validate-------------------
ave Recall 0.6753361017589962
ave NDCG 0.5773988784633947
----------------test-------------------
ave Recall 0.66055894325149
ave NDCG 0.5532824423328319
running time for this epoch:  32.63909339904785
running time until now:  985.1204462051392
-------------------------an epoch ends ---------------------------
i_epoch:  28
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12505743
time for this batch:  0.467
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14089906
time for this batch:  0.478
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13757011
time for this batch:  0.435
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14417896
time for this batch:  0.433
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14996508
time for this batch:  0.426
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14221488
time for this batch:  0.538
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.16273595
time for this batch:  0.409
-----------------a batch ends---------------
train loss for this epoch:  0.142359
----------------validate-------------------
ave Recall 0.6754186128527961
ave NDCG 0.5751826001482698
----------------test-------------------
ave Recall 0.6547618481855639
ave NDCG 0.5490173759570883
running time for this epoch:  32.593082427978516
running time until now:  1017.7135734558105
-------------------------an epoch ends ---------------------------
i_epoch:  29
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12559691
time for this batch:  0.425
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14686371
time for this batch:  0.534
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13998157
time for this batch:  0.507
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13952184
time for this batch:  0.509
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13022214
time for this batch:  0.428
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.1402694
time for this batch:  0.514
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.13075566
time for this batch:  0.51
-----------------a batch ends---------------
train loss for this epoch:  0.141868
----------------validate-------------------
ave Recall 0.6730389601928706
ave NDCG 0.5701606040702637
----------------test-------------------
ave Recall 0.6606619320354893
ave NDCG 0.5495284575861048
running time for this epoch:  33.76980900764465
running time until now:  1051.483423948288
-------------------------an epoch ends ---------------------------
i_epoch:  30
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.142359
time for this batch:  0.383
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.1338202
time for this batch:  0.433
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14817241
time for this batch:  0.482
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.15329209
time for this batch:  0.489
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13301653
time for this batch:  0.419
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13683547
time for this batch:  0.499
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.17253661
time for this batch:  0.389
-----------------a batch ends---------------
train loss for this epoch:  0.141198
----------------validate-------------------
ave Recall 0.6703096717523263
ave NDCG 0.5700192907362948
----------------test-------------------
ave Recall 0.6574845342179513
ave NDCG 0.5497707627116155
running time for this epoch:  33.33591270446777
running time until now:  1084.8193764686584
-------------------------an epoch ends ---------------------------
i_epoch:  31
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13538778
time for this batch:  0.458
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.1501483
time for this batch:  0.524
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.123500586
time for this batch:  0.441
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14182189
time for this batch:  0.338
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14610007
time for this batch:  0.507
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13372107
time for this batch:  0.497
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15359181
time for this batch:  0.52
-----------------a batch ends---------------
train loss for this epoch:  0.14005
----------------validate-------------------
ave Recall 0.6740783321571805
ave NDCG 0.5710807883303942
----------------test-------------------
ave Recall 0.6586440876159384
ave NDCG 0.5500574281404998
running time for this epoch:  34.02409291267395
running time until now:  1118.8435146808624
-------------------------an epoch ends ---------------------------
i_epoch:  32
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13048273
time for this batch:  0.471
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13766232
time for this batch:  0.37
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14887692
time for this batch:  0.486
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13718465
time for this batch:  0.459
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.1438254
time for this batch:  0.444
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.15672155
time for this batch:  0.435
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.1355722
time for this batch:  0.492
-----------------a batch ends---------------
train loss for this epoch:  0.140094
----------------validate-------------------
ave Recall 0.6724895468617161
ave NDCG 0.5721676859519679
----------------test-------------------
ave Recall 0.6641327639517972
ave NDCG 0.5546030689057414
running time for this epoch:  34.433029890060425
running time until now:  1153.2765984535217
-------------------------an epoch ends ---------------------------
i_epoch:  33
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14174417
time for this batch:  0.489
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13264135
time for this batch:  0.476
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13395092
time for this batch:  0.497
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14720654
time for this batch:  0.513
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13983114
time for this batch:  0.409
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.1505131
time for this batch:  0.549
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.12987977
time for this batch:  0.437
-----------------a batch ends---------------
train loss for this epoch:  0.140273
----------------validate-------------------
ave Recall 0.6747503932670204
ave NDCG 0.5710942993453342
----------------test-------------------
ave Recall 0.6607159757754135
ave NDCG 0.5486694031278183
running time for this epoch:  33.65649223327637
running time until now:  1186.933143377304
-------------------------an epoch ends ---------------------------
i_epoch:  34
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13454401
time for this batch:  0.469
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13031578
time for this batch:  0.602
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13772711
time for this batch:  0.43
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14433932
time for this batch:  0.522
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.12955716
time for this batch:  0.441
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14333862
time for this batch:  0.36
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.1307119
time for this batch:  0.47
-----------------a batch ends---------------
train loss for this epoch:  0.139782
----------------validate-------------------
ave Recall 0.6728505788529416
ave NDCG 0.5683913583529502
----------------test-------------------
ave Recall 0.6538656474326345
ave NDCG 0.5443357352445943
running time for this epoch:  33.49396085739136
running time until now:  1220.4271507263184
-------------------------an epoch ends ---------------------------
i_epoch:  35
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13983974
time for this batch:  0.397
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13214058
time for this batch:  0.489
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13244665
time for this batch:  0.49
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13366534
time for this batch:  0.402
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13589063
time for this batch:  0.56
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14607258
time for this batch:  0.458
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.13607588
time for this batch:  0.585
-----------------a batch ends---------------
train loss for this epoch:  0.140826
----------------validate-------------------
ave Recall 0.6658166181685705
ave NDCG 0.5646743211579897
----------------test-------------------
ave Recall 0.6520137061579567
ave NDCG 0.5468996252091542
running time for this epoch:  33.75576663017273
running time until now:  1254.1829671859741
-------------------------an epoch ends ---------------------------
i_epoch:  36
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12588142
time for this batch:  0.363
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14681962
time for this batch:  0.469
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13069497
time for this batch:  0.518
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13766387
time for this batch:  0.503
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.15032393
time for this batch:  0.484
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14494568
time for this batch:  0.493
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.13592911
time for this batch:  0.466
-----------------a batch ends---------------
train loss for this epoch:  0.139963
----------------validate-------------------
ave Recall 0.6635488665141828
ave NDCG 0.5629487969044272
----------------test-------------------
ave Recall 0.6533632397910731
ave NDCG 0.5462579075720607
running time for this epoch:  33.40546107292175
running time until now:  1287.588472366333
-------------------------an epoch ends ---------------------------
i_epoch:  37
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14468075
time for this batch:  0.425
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13495281
time for this batch:  0.392
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.1308684
time for this batch:  0.447
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.12893361
time for this batch:  0.372
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.15173596
time for this batch:  0.424
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13030243
time for this batch:  0.598
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15705553
time for this batch:  0.559
-----------------a batch ends---------------
train loss for this epoch:  0.139583
----------------validate-------------------
ave Recall 0.6753410350020651
ave NDCG 0.5682645081777457
----------------test-------------------
ave Recall 0.6600590913147093
ave NDCG 0.5524885430946267
running time for this epoch:  31.754833221435547
running time until now:  1319.3433480262756
-------------------------an epoch ends ---------------------------
i_epoch:  38
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.1397574
time for this batch:  0.398
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.12978731
time for this batch:  0.434
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14864679
time for this batch:  0.427
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14146286
time for this batch:  0.505
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14135939
time for this batch:  0.556
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.1302836
time for this batch:  0.483
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14581141
time for this batch:  0.437
-----------------a batch ends---------------
train loss for this epoch:  0.138265
----------------validate-------------------
ave Recall 0.6727782878740851
ave NDCG 0.5668645187093335
----------------test-------------------
ave Recall 0.6556539137310737
ave NDCG 0.5500573738515672
running time for this epoch:  31.964946746826172
running time until now:  1351.308351278305
-------------------------an epoch ends ---------------------------
i_epoch:  39
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.1433344
time for this batch:  0.425
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.12605067
time for this batch:  0.49
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13716996
time for this batch:  0.415
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14507166
time for this batch:  0.443
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13336107
time for this batch:  0.512
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.1324726
time for this batch:  0.479
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15657593
time for this batch:  0.478
-----------------a batch ends---------------
train loss for this epoch:  0.139428
----------------validate-------------------
ave Recall 0.6711373181473059
ave NDCG 0.5681313000035948
----------------test-------------------
ave Recall 0.6590968181786677
ave NDCG 0.5504215696260123
running time for this epoch:  31.441805362701416
running time until now:  1382.7501993179321
-------------------------an epoch ends ---------------------------
i_epoch:  40
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13342881
time for this batch:  0.408
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13365619
time for this batch:  0.471
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14777538
time for this batch:  0.56
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13019554
time for this batch:  0.475
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14080225
time for this batch:  0.483
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13531527
time for this batch:  0.448
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15282425
time for this batch:  0.418
-----------------a batch ends---------------
train loss for this epoch:  0.138216
----------------validate-------------------
ave Recall 0.6701835694098873
ave NDCG 0.5700978744338958
----------------test-------------------
ave Recall 0.6606673117360556
ave NDCG 0.5536715000030746
running time for this epoch:  31.43113875389099
running time until now:  1414.181381225586
-------------------------an epoch ends ---------------------------
i_epoch:  41
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14318077
time for this batch:  0.387
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.12853855
time for this batch:  0.469
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.12540613
time for this batch:  0.448
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.1352646
time for this batch:  0.431
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14880481
time for this batch:  0.513
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14844835
time for this batch:  0.518
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.13561368
time for this batch:  0.36
-----------------a batch ends---------------
train loss for this epoch:  0.137451
----------------validate-------------------
ave Recall 0.6689448992729703
ave NDCG 0.5643701695136274
----------------test-------------------
ave Recall 0.6563489369072134
ave NDCG 0.549690490405119
running time for this epoch:  30.883761644363403
running time until now:  1445.065183877945
-------------------------an epoch ends ---------------------------
i_epoch:  42
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.1405859
time for this batch:  0.436
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13061905
time for this batch:  0.495
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14065164
time for this batch:  0.444
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14222494
time for this batch:  0.443
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14276962
time for this batch:  0.393
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14904115
time for this batch:  0.529
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14020453
time for this batch:  0.491
-----------------a batch ends---------------
train loss for this epoch:  0.138263
----------------validate-------------------
ave Recall 0.6675934943481239
ave NDCG 0.565565702494599
----------------test-------------------
ave Recall 0.6569074211436711
ave NDCG 0.5487084633742139
running time for this epoch:  32.072131395339966
running time until now:  1477.1373581886292
-------------------------an epoch ends ---------------------------
i_epoch:  43
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12838851
time for this batch:  0.361
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13408479
time for this batch:  0.433
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13492042
time for this batch:  0.493
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14534512
time for this batch:  0.469
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.120536625
time for this batch:  0.49
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14152868
time for this batch:  0.415
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15874702
time for this batch:  0.44
-----------------a batch ends---------------
train loss for this epoch:  0.13817
----------------validate-------------------
ave Recall 0.6718803767616603
ave NDCG 0.570849578562217
----------------test-------------------
ave Recall 0.6601969373218987
ave NDCG 0.552400320388536
running time for this epoch:  32.117274045944214
running time until now:  1509.2546865940094
-------------------------an epoch ends ---------------------------
i_epoch:  44
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13841595
time for this batch:  0.389
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13610893
time for this batch:  0.399
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13370666
time for this batch:  0.502
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.12798932
time for this batch:  0.504
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13287047
time for this batch:  0.432
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14659157
time for this batch:  0.398
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.13799411
time for this batch:  0.469
-----------------a batch ends---------------
train loss for this epoch:  0.138933
----------------validate-------------------
ave Recall 0.6721031609635895
ave NDCG 0.5705465352832565
----------------test-------------------
ave Recall 0.6578966724366463
ave NDCG 0.5513842885401882
running time for this epoch:  31.65391516685486
running time until now:  1540.9086453914642
-------------------------an epoch ends ---------------------------
i_epoch:  45
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13534176
time for this batch:  0.433
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.12934773
time for this batch:  0.481
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14327604
time for this batch:  0.459
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.15059316
time for this batch:  0.456
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14337935
time for this batch:  0.491
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13955933
time for this batch:  0.365
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.1364604
time for this batch:  0.329
-----------------a batch ends---------------
train loss for this epoch:  0.138132
----------------validate-------------------
ave Recall 0.6730480698989993
ave NDCG 0.5666585662155641
----------------test-------------------
ave Recall 0.6576120020818774
ave NDCG 0.5491651047099316
running time for this epoch:  30.564467906951904
running time until now:  1571.473159313202
-------------------------an epoch ends ---------------------------
i_epoch:  46
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14125931
time for this batch:  0.406
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14616627
time for this batch:  0.429
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.12826142
time for this batch:  0.44
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.1338636
time for this batch:  0.397
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.1368948
time for this batch:  0.498
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14308019
time for this batch:  0.505
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14483292
time for this batch:  0.478
-----------------a batch ends---------------
train loss for this epoch:  0.137752
----------------validate-------------------
ave Recall 0.668586793795636
ave NDCG 0.5661562693018927
----------------test-------------------
ave Recall 0.6613597128198018
ave NDCG 0.5541772311575334
running time for this epoch:  30.780853986740112
running time until now:  1602.254058599472
-------------------------an epoch ends ---------------------------
i_epoch:  47
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12975869
time for this batch:  0.45
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13734892
time for this batch:  0.55
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13292778
time for this batch:  0.408
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14148939
time for this batch:  0.4
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.12878488
time for this batch:  0.44
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14513727
time for this batch:  0.431
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14543606
time for this batch:  0.461
-----------------a batch ends---------------
train loss for this epoch:  0.138296
----------------validate-------------------
ave Recall 0.665445884792355
ave NDCG 0.5650035817472584
----------------test-------------------
ave Recall 0.6585507569862884
ave NDCG 0.5521285359847062
running time for this epoch:  30.906007289886475
running time until now:  1633.1601085662842
-------------------------an epoch ends ---------------------------
i_epoch:  48
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12107383
time for this batch:  0.347
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.12718059
time for this batch:  0.462
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14014393
time for this batch:  0.438
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13971959
time for this batch:  0.371
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.1328096
time for this batch:  0.472
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14323805
time for this batch:  0.407
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.151414
time for this batch:  0.488
-----------------a batch ends---------------
train loss for this epoch:  0.137779
----------------validate-------------------
ave Recall 0.6688308795837787
ave NDCG 0.565040816487093
----------------test-------------------
ave Recall 0.6590173215108951
ave NDCG 0.5520934302043911
running time for this epoch:  30.616058111190796
running time until now:  1663.7762160301208
-------------------------an epoch ends ---------------------------
i_epoch:  49
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.1244129
time for this batch:  0.356
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14466256
time for this batch:  0.427
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13815446
time for this batch:  0.49
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.12531555
time for this batch:  0.563
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13466977
time for this batch:  0.46
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13590121
time for this batch:  0.405
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.13184857
time for this batch:  0.404
-----------------a batch ends---------------
train loss for this epoch:  0.136135
----------------validate-------------------
ave Recall 0.6709366833772112
ave NDCG 0.5637289051540672
----------------test-------------------
ave Recall 0.6575315530297048
ave NDCG 0.5511887156762012
running time for this epoch:  31.326887130737305
running time until now:  1695.1031455993652
-------------------------an epoch ends ---------------------------
i_epoch:  50
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13421778
time for this batch:  0.522
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.1322413
time for this batch:  0.462
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.123622045
time for this batch:  0.399
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.15081012
time for this batch:  0.392
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13850777
time for this batch:  0.496
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14405149
time for this batch:  0.424
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14488685
time for this batch:  0.48
-----------------a batch ends---------------
train loss for this epoch:  0.136285
----------------validate-------------------
ave Recall 0.6729442363866603
ave NDCG 0.5652216518240744
----------------test-------------------
ave Recall 0.6574410488503587
ave NDCG 0.5500123035151951
running time for this epoch:  31.685019493103027
running time until now:  1726.7882103919983
-------------------------an epoch ends ---------------------------
i_epoch:  51
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13520092
time for this batch:  0.416
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.1403918
time for this batch:  0.446
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.12723012
time for this batch:  0.374
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14936388
time for this batch:  0.347
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.1420148
time for this batch:  0.473
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.11211028
time for this batch:  0.434
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14584513
time for this batch:  0.41
-----------------a batch ends---------------
train loss for this epoch:  0.136913
----------------validate-------------------
ave Recall 0.6660698588742102
ave NDCG 0.5601969340205164
----------------test-------------------
ave Recall 0.6595480811351547
ave NDCG 0.5504616964021747
running time for this epoch:  29.92622709274292
running time until now:  1756.7144825458527
-------------------------an epoch ends ---------------------------
i_epoch:  52
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13617904
time for this batch:  0.43
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14014873
time for this batch:  0.449
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14584634
time for this batch:  0.434
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.1294997
time for this batch:  0.506
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13852715
time for this batch:  0.425
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.12989101
time for this batch:  0.448
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.12109429
time for this batch:  0.461
-----------------a batch ends---------------
train loss for this epoch:  0.137334
----------------validate-------------------
ave Recall 0.6689550657749818
ave NDCG 0.5621344701946059
----------------test-------------------
ave Recall 0.6572917396382486
ave NDCG 0.5505579959536515
running time for this epoch:  33.681506633758545
running time until now:  1790.3960313796997
-------------------------an epoch ends ---------------------------
i_epoch:  53
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13442704
time for this batch:  0.351
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14183971
time for this batch:  0.437
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13374677
time for this batch:  0.481
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13180506
time for this batch:  0.49
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13920861
time for this batch:  0.493
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13219057
time for this batch:  0.511
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15464629
time for this batch:  0.447
-----------------a batch ends---------------
train loss for this epoch:  0.135277
----------------validate-------------------
ave Recall 0.6702200307151644
ave NDCG 0.563872537161781
----------------test-------------------
ave Recall 0.651060848636774
ave NDCG 0.5436222267047174
running time for this epoch:  32.496246337890625
running time until now:  1822.892320394516
-------------------------an epoch ends ---------------------------
i_epoch:  54
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13316816
time for this batch:  0.426
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.11838941
time for this batch:  0.344
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.12124187
time for this batch:  0.341
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.1333655
time for this batch:  0.373
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.1522071
time for this batch:  0.536
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14335772
time for this batch:  0.487
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.16061111
time for this batch:  0.437
-----------------a batch ends---------------
train loss for this epoch:  0.135972
----------------validate-------------------
ave Recall 0.6687472523318275
ave NDCG 0.565505089617194
----------------test-------------------
ave Recall 0.6514206769348216
ave NDCG 0.5471181370019347
running time for this epoch:  32.021427631378174
running time until now:  1854.9137904644012
-------------------------an epoch ends ---------------------------
i_epoch:  55
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13388795
time for this batch:  0.495
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.15251309
time for this batch:  0.474
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13550562
time for this batch:  0.439
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.12662551
time for this batch:  0.423
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14747456
time for this batch:  0.475
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.12707186
time for this batch:  0.459
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.13913324
time for this batch:  0.454
-----------------a batch ends---------------
train loss for this epoch:  0.135299
----------------validate-------------------
ave Recall 0.6737435756449233
ave NDCG 0.5697748289767222
----------------test-------------------
ave Recall 0.6497968195375254
ave NDCG 0.5470104251948321
running time for this epoch:  32.07332158088684
running time until now:  1886.9871535301208
-------------------------an epoch ends ---------------------------
i_epoch:  56
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12597895
time for this batch:  0.354
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.1275041
time for this batch:  0.4
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14029291
time for this batch:  0.436
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.12726778
time for this batch:  0.489
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.15317188
time for this batch:  0.539
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.1344671
time for this batch:  0.453
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15534277
time for this batch:  0.485
-----------------a batch ends---------------
train loss for this epoch:  0.136105
----------------validate-------------------
ave Recall 0.672955696397532
ave NDCG 0.5715244560854944
----------------test-------------------
ave Recall 0.6533926500325663
ave NDCG 0.5470305967796246
Early stop at the 57-th epoch
In [17]:
print ("start preparing for vali and test")
vali_u_v, vali_x_poi, vali_x_user, vali_x_adj, vali_y_real = prepare_validate_test(vali, hyper_param)
test_u_v, test_x_poi, test_x_user, test_x_adj, test_y_real = prepare_validate_test(test, hyper_param)
start preparing for vali and test
In [18]:
#8.4: validate and test the model
print ("---------------validation-------------------")
all_recall, all_ndcg, ave_recall, ave_ndcg, vali_output, vali_real =\
    validate_test(trained_model, hyper_param, vali_u_v, vali_x_poi, vali_x_user, vali_x_adj, vali_y_real, True)
print ("-----------finish model validation---------------")
---------------validation-------------------
ave Recall 0.672955696397532
ave NDCG 0.5715244560854944
-----------finish model validation---------------
In [19]:
print ("---------------test-------------------")
all_recall, all_ndcg, ave_recall, ave_ndcg, test_output, test_real =\
    validate_test(trained_model, hyper_param, test_u_v, test_x_poi, test_x_user, test_x_adj, test_y_real, True)
print ("-----------finish model validation---------------")
---------------test-------------------
ave Recall 0.6533926500325663
ave NDCG 0.5470305967796246
-----------finish model validation---------------

9: save¶

In [20]:
list_vali_hat = vali_output.cpu().detach().numpy().tolist()
list_vali_real = vali_real.cpu().detach().numpy().tolist()
print(len(list_vali_hat))
print(len(list_vali_hat[0]))
print(len(list_vali_hat[0][0]))
print(len(list_vali_hat[0][0][0]))

list_test_hat = test_output.cpu().detach().numpy().tolist()
list_test_real = test_real.cpu().detach().numpy().tolist()
print(len(list_test_hat))
print(len(list_test_hat[0]))
print(len(list_test_hat[0][0]))
print(len(list_test_hat[0][0][0]))
18
1
1827
80
37
1
1827
80
In [21]:
result = {"vali_hat": list_vali_hat, "vali_real": list_vali_real, \
          "test_hat": list_test_hat, "test_real": list_test_real}

subfile = case+'/vali_predict.json'
savefile = open(subfile,'w')
json.dump(result, savefile)
savefile.close()

df = json.load(open(subfile))
df.keys()
print(len(df["test_real"]))
37
In [ ]: